**** dT 0.000 * top TEST ../../../../bin/vinyltest/tests/r03940.vtc starting **** top extmacro def pkg_version=trunk **** top extmacro def pkg_branch=trunk **** top extmacro def pwd=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest **** top extmacro def date(...) **** top extmacro def string(...) **** top extmacro def localhost=127.0.0.1 **** top extmacro def bad_backend=127.0.0.1:57143 **** top extmacro def listen_addr=127.0.0.1:0 **** top extmacro def bad_ip=192.0.2.255 **** top extmacro def topbuild=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub **** top extmacro def topsrc=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/../.. **** top macro def testdir=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest/../../../../bin/vinyltest/tests **** top macro def tmpdir=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8 **** top macro def vtcid=vtc.428840.769974d8 ** top === vtest "test startup_timeout vs. stevedore init / open" * top VTEST test startup_timeout vs. stevedore init / open ** top === vinyl v1 -arg "-sdebug=debug,dinit=5s -pstartup_timeout=3s -... **** dT 0.012 ** v1 Launch *** v1 CMD: cd ${pwd} && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 65366' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v1/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -sdebug=debug,dinit=5s -pstartup_timeout=3s -pcli_timeout=2s -p feature=+no_coredump *** v1 CMD: cd /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 65366' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v1/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -sdebug=debug,dinit=5s -pstartup_timeout=3s -pcli_timeout=2s -p feature=+no_coredump *** v1 PID: 428890 **** v1 macro def v1_pid=428890 **** v1 macro def v1_name=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v1 **** dT 0.051 *** v1 debug|Warning: mlock() of VSM failed: Not owner (1) **** dT 0.054 *** v1 debug|Debug: *** v1 debug|Version: vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v1 debug|Debug: Platform: -jsolaris,-sdebug,-sdefault,-hcritbit *** v1 debug| *** v1 debug|200 290 *** v1 debug|----------------------------- *** v1 debug|Vinyl Cache CLI 1.0 *** v1 debug|----------------------------- *** v1 debug|-jsolaris,-sdebug,-sdefault,-hcritbit *** v1 debug|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v1 debug| *** v1 debug|Type 'help' for command list. *** v1 debug|Type 'quit' to close CLI session. *** v1 debug|Type 'start' to launch worker process. *** v1 debug| **** dT 0.151 **** v1 CLIPOLL 1 0x1 0x0 0x0 **** dT 0.152 *** v1 CLI connection fd = 4 *** v1 CLI RX 107 **** v1 CLI RX|turhejwcmesahlmedekhuhfcwzhutymf **** v1 CLI RX| **** v1 CLI RX|Authentication required. **** v1 CLI TX|auth 6522a5ab8ce57db8bd73e6f52b8cb1f3b70f1a07d1dc8a6f2c33b19f17e9a8ee **** dT 0.153 *** v1 CLI RX 200 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Vinyl Cache CLI 1.0 **** v1 CLI RX|----------------------------- **** v1 CLI RX|-jsolaris,-sdebug,-sdefault,-hcritbit **** v1 CLI RX|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 **** v1 CLI RX| **** v1 CLI RX|Type 'help' for command list. **** v1 CLI RX|Type 'quit' to close CLI session. **** v1 CLI RX|Type 'start' to launch worker process. **** v1 CLI TX|vcl.inline vcl1 << %XJEIFLH|)Xspa8P **** v1 CLI TX|vcl 4.1; **** v1 CLI TX|backend none none; **** v1 CLI TX|%XJEIFLH|)Xspa8P **** dT 0.253 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.353 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.453 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.553 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.653 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.753 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.853 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.872 *** v1 CLI RX 200 **** v1 CLI RX|Message from VCC-compiler: **** v1 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v1 CLI RX|Message from C-compiler: **** v1 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v1 CLI RX|Message from dlopen: **** v1 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v1 CLI RX|VCL compiled. **** v1 CLI TX|vcl.use vcl1 *** v1 CLI RX 200 **** v1 CLI RX|VCL 'vcl1' now active ** top === vinyl v1 -cliexpect \ **** v1 CLI TX|start **** dT 0.886 *** v1 debug|Debug: *** v1 debug| Child (429102) Started **** dT 0.954 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.054 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.154 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.254 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.354 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.454 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.554 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.654 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.754 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.854 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.954 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.054 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.154 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.254 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.354 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.455 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.555 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.655 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.755 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.855 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.955 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.055 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.155 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.255 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.355 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.455 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.555 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.655 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.756 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.856 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.886 *** v1 debug|Error: Child failed on launch within startup_timeout=3.00s *** v1 debug|Error: Child (429102) said Child starts *** v1 debug| *** v1 debug|Error: *** v1 debug|Child (429102) said -sdebug init delay 5.000000s *** v1 debug|Error: *** v1 debug|Child (429102) said -sdebug open delay in init 0.000000s **** dT 3.956 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.056 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.156 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.256 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.356 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.456 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.556 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.656 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.756 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.856 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.956 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.056 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.156 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.256 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.356 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.457 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.557 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.657 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.757 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.857 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.925 *** v1 debug|Error: Child (429102) not dying (waitpid = 0), killing *** v1 debug|Child (429102) died signal=6 *** v1 debug|Error: *** v1 debug| *** v1 debug|Child (429102) Panic at: Tue, 17 Mar 2026 03:21:48 GMT *** v1 debug|Assert error in CLI_Run(), ../../../../bin/vinyld/cache/cache_cli.c line 103: *** v1 debug| Condition((VCLI_WriteResult(heritage.cli_fd, CLIS_OK, \"Ready\")) == 0) not true. *** v1 debug|version = vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4, vrt api = 23.0 *** v1 debug|ident = -jsolaris,-sdebug,-sdefault,-hcritbit,ports *** v1 debug|now = 5929784.492576 (mono), 1773717708.058603 (real) *** v1 debug|Backtrace: *** v1 debug| 8149fb3: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'vbt_execinfo+0x39 [0x8149fb3] *** v1 debug| 814a1c4: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VBT_format+0x2d [0x814a1c4] *** v1 debug| 80aecdd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_backtrace+0x34 [0x80aecdd] *** v1 debug| 80af020: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_ic+0x27c [0x80af020] *** v1 debug| 81495b9: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-ca *** v1 debug|che-trunk/_build/sub/bin/vinyld/vinyld'VAS_Fail+0x3a [0x81495b9] *** v1 debug| 80867cb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'CLI_Run+0x4a [0x80867cb] *** v1 debug| 80a9030: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'child_main+0x3cb [0x80a9030] *** v1 debug| 80f805e: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_launch_child+0x3f8 [0x80f805e] *** v1 debug| 80f8e52: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mch_cli_server_start+0x28 [0x80f8e52] *** v1 debug| 814b159: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_dispatch+0x2ec [0x814b159] *** v1 debug| 814b3cb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_exec+0x260 [0x814b3cb] *** v1 debug| 814b8a8: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_feed+0x392 [0x814b8a8] *** v1 debug| 814c846: /tmp/vt *** v1 debug|est.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VCLS_Poll+0x2a4 [0x814c846] *** v1 debug| 80f9b14: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_cli_callback2+0x1d [0x80f9b14] *** v1 debug| 814ed4d: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VEV_Once+0x41d [0x814ed4d] *** v1 debug| 814e74d: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VEV_Loop+0xb7 [0x814e74d] *** v1 debug| 8100131: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'main+0x17b5 [0x8100131] *** v1 debug| 80728bb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'_start_crt+0x9a [0x80728bb] *** v1 debug| 807278a: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'_start+0x1a [0x807278a] *** v1 debug|errno = 32 (Broken pipe) *** v1 debug|argv = { *** v1 debug| [0] = \"vinyld\", *** v1 debug| [1] = \"-d\", *** v1 debug| [2] = \"-n\", *** v1 debug| [3] = \"/tmp/vtest.gcc13_m32_IPv4 *** v1 debug|_uffix/_vtest_tmp/vtc.428840.769974d8/v1\", *** v1 debug| [4] = \"-i\", *** v1 debug| [5] = \"v1\", *** v1 debug| [6] = \"-l\", *** v1 debug| [7] = \"2m\", *** v1 debug| [8] = \"-p\", *** v1 debug| [9] = \"auto_restart=off\", *** v1 debug| [10] = \"-p\", *** v1 debug| [11] = \"syslog_cli_traffic=off\", *** v1 debug| [12] = \"-p\", *** v1 debug| [13] = \"thread_pool_min=10\", *** v1 debug| [14] = \"-p\", *** v1 debug| [15] = \"debug=+vtc_mode\", *** v1 debug| [16] = \"-p\", *** v1 debug| [17] = \"vsl_mask=+Debug,+H2RxHdr,+H2RxBody\", *** v1 debug| [18] = \"-p\", *** v1 debug| [19] = \"h2_initial_window_size=1m\", *** v1 debug| [20] = \"-p\", *** v1 debug| [21] = \"h2_rx_window_low_water=64k\", *** v1 debug| [22] = \"-a\", *** v1 debug| [23] = \"127.0.0.1:0\", *** v1 debug| [24] = \"-M\", *** v1 debug| [25] = \"127.0.0.1 65366\", *** v1 debug| [26] = \"-P\", *** v1 debug| [27] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v1/vinyld.pid\", *** v1 debug| [28] = \"-p\", *** v1 debug| [29] = \"vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs:\", *** v1 debug| [30] = \"-sdebug=debug,dinit=5s\", *** v1 debug| [31] = \"-pstartup_timeout=3s\", *** v1 debug| [32] = \"-pcli_timeout=2s\", *** v1 debug| [33] = \"-p\", *** v1 debug| [34] = \"feature=+no_coredump\", *** v1 debug|} *** v1 debug|pthread.self = 1 *** v1 debug|pthread.name = (cache-main) *** v1 debug|thr.req = *** v1 debug| NULL *** v1 debug|thr.busyobj = NULL *** v1 debug|thr.worker = NULL *** v1 debug|vmods = { *** v1 debug|}, *** v1 debug|pools = { *** v1 debug| pool = 827efb8 { *** v1 debug| nidle = 9, *** v1 debug| nthr = 10, *** v1 debug| lqueue = 0 *** v1 debug| }, *** v1 debug| pool = 82bf920 { *** v1 debug| nidle = 9, *** v1 debug| nthr = 10, *** v1 debug| lqueue = 0 *** v1 debug| }, *** v1 debug|}, *** v1 debug| *** v1 debug| *** v1 debug|Error: Child (429102) said Security: proc_setid missing, uid/gid unchanged *** v1 debug|Error: Child (429102) said -sdebug open delay 0.000000s *** v1 debug|Debug: Child cleanup complete *** v1 CLI RX 400 **** v1 CLI RX|Child failed on launch within startup_timeout=3.00s ** v1 CLI 400 ** top === shell {vinyladm -n ${v1_name} panic.clear || true } **** top shell_cmd|set -e ;exec 2>&1 ; vinyladm -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v1 panic.clear || true **** dT 5.982 **** top shell_out| **** top shell_status = 0x0000 ** top === vinyl v1 -wait ** v1 Wait **** v1 CLI TX|backend.list *** v1 CLI RX 101 **** v1 CLI RX|Unknown request in manager process (child not running). **** v1 CLI RX|Type 'help' for more info. ** v1 Stop **** v1 CLI TX|stop *** v1 CLI RX 300 **** v1 CLI RX|Child in state stopped *** v1 wait-stopped **** v1 CLI TX|status *** v1 CLI RX 200 **** v1 CLI RX|Child in state stopped **** v1 CLI TX|panic.show *** v1 CLI RX 300 **** v1 CLI RX|Child has not panicked or panic has been cleared *** v1 debug|Info: manager stopping child *** v1 debug|Info: manager dies **** v1 STDOUT EOF **** dT 6.057 ** v1 WAIT4 pid=428890 status=0x4000 (user 0.633000 sys 0.139000) ** top === process p1 { vinyld \ **** dT 6.070 **** p1 CMD: vinyld \ -sdebug=debug,dinit=5s \ -pstartup_timeout=3s -pcli_timeout=2s \ -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p1 -a :0 -b none 2>&1 **** dT 6.071 *** p1 PID: 430809 **** dT 6.072 **** p1 macro def p1_pid=430809 **** p1 macro def p1_dir=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p1 **** p1 macro def p1_out=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p1/term **** p1 macro def p1_err=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p1/stderr **** dT 11.985 **** p1 stderr read 0 **** p1 stdout read 0 **** dT 11.987 ** p1 WAIT4 pid=430809 status=0x0200 (user 0.004000 sys 0.007000) **** p1 macro undef p1_pid **** p1 stdout 2887 bytes, stderr 0 bytes ** top === shell {grep -q "Child failed on launch within startup_timeou... **** top shell_cmd|set -e ;exec 2>&1 ; grep -q "Child failed on launch within startup_timeout=3.00s" /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p1/term **** dT 11.997 **** top shell_status = 0x0000 ** top === vinyl v2 -arg "-sdebug=debug,dopen=5s -pstartup_timeout=2s -... **** dT 12.007 ** v2 Launch *** v2 CMD: cd ${pwd} && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v2 -i v2 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 57995' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v2/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -sdebug=debug,dopen=5s -pstartup_timeout=2s -pcli_timeout=3s -p feature=+no_coredump *** v2 CMD: cd /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest && exec vinyld -d -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v2 -i v2 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 57995' -P /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v2/vinyld.pid -p vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -sdebug=debug,dopen=5s -pstartup_timeout=2s -pcli_timeout=3s -p feature=+no_coredump *** v2 PID: 432237 **** v2 macro def v2_pid=432237 **** v2 macro def v2_name=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v2 **** dT 12.040 *** v2 debug|Warning: mlock() of VSM failed: Not owner (1 *** v2 debug|) **** dT 12.044 *** v2 debug|Debug: Version: vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v2 debug| *** v2 debug|Debug: *** v2 debug| Platform: -jsolaris,-sdebug,-sdefault,-hcritbit *** v2 debug| *** v2 debug|200 290 *** v2 debug|----------------------------- *** v2 debug|Vinyl Cache CLI 1.0 *** v2 debug|----------------------------- *** v2 debug|-jsolaris,-sdebug,-sdefault,-hcritbit *** v2 debug|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 *** v2 debug| *** v2 debug|Type 'help' for command list. *** v2 debug|Type 'quit' to close CLI session. *** v2 debug|Type 'start' to launch worker process. *** v2 debug| **** dT 12.141 **** v2 CLIPOLL 1 0x1 0x0 0x0 *** v2 CLI connection fd = 11 *** v2 CLI RX 107 **** v2 CLI RX|tibmvncanocmoejslgnmsyesbzqegaoe **** v2 CLI RX| **** v2 CLI RX|Authentication required. **** dT 12.142 **** v2 CLI TX|auth f301d54f9e02ba3c1bb55753baf1fdf280873b93bc2e115542b6b28f52b6fe22 *** v2 CLI RX 200 **** v2 CLI RX|----------------------------- **** v2 CLI RX|Vinyl Cache CLI 1.0 **** v2 CLI RX|----------------------------- **** v2 CLI RX|-jsolaris,-sdebug,-sdefault,-hcritbit **** v2 CLI RX|vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4 **** v2 CLI RX| **** v2 CLI RX|Type 'help' for command list. **** v2 CLI RX|Type 'quit' to close CLI session. **** v2 CLI RX|Type 'start' to launch worker process. **** v2 CLI TX|vcl.inline vcl1 << %XJEIFLH|)Xspa8P **** v2 CLI TX|vcl 4.1; **** v2 CLI TX|backend none none; **** v2 CLI TX|%XJEIFLH|)Xspa8P **** dT 12.242 *** v2 vsl|No VSL chunk found (child not started ?) **** dT 12.343 *** v2 vsl|No VSL chunk found (child not started ?) **** dT 12.443 *** v2 vsl|No VSL chunk found (child not started ?) **** dT 12.543 *** v2 vsl|No VSL chunk found (child not started ?) **** dT 12.643 *** v2 vsl|No VSL chunk found (child not started ?) **** dT 12.743 *** v2 vsl|No VSL chunk found (child not started ?) **** dT 12.843 *** v2 vsl|No VSL chunk found (child not started ?) **** dT 12.848 *** v2 CLI RX 200 **** v2 CLI RX|Message from VCC-compiler: **** v2 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v2 CLI RX|Message from C-compiler: **** v2 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v2 CLI RX|Message from dlopen: **** v2 CLI RX|Security: proc_setid missing, uid/gid unchanged **** v2 CLI RX|VCL compiled. **** v2 CLI TX|vcl.use vcl1 *** v2 CLI RX 200 **** v2 CLI RX|VCL 'vcl1' now active ** top === vinyl v2 -cliexpect \ **** v2 CLI TX|start **** dT 12.859 *** v2 debug|Debug: *** v2 debug| Child (432322) Started **** dT 15.859 *** v2 debug|Error: Child failed on launch within cli_timeout=3.00s (tip: set startup_timeout) **** dT 15.860 *** v2 debug|Error: Child (432322) said Child starts *** v2 debug| *** v2 debug|Error: *** v2 debug| Child (432322) said -sdebug init delay 0.000000s *** v2 debug| *** v2 debug|Error: *** v2 debug| Child (432322) said -sdebug open delay in init 5.000000s *** v2 debug| *** v2 debug|Error: *** v2 debug| *** v2 debug|Child (432322) said Security: proc_setid missing, uid/gid unchanged *** v2 debug| *** v2 debug|Error: *** v2 debug| *** v2 debug|Child (432322) said -sdebug open delay 5.000000s *** v2 debug| **** dT 15.960 *** v2 debug|Error: Child (432322) died signal=6 *** v2 debug|Error: *** v2 debug|Child (432322) Panic at: Tue, 17 Mar 2026 03:21:58 GMT *** v2 debug|Wrong turn at ../../../../bin/vinyld/cache/cache_main.c:387: *** v2 debug|It's time for the big quit *** v2 debug|version = vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4, vrt api = 23.0 *** v2 debug|ident = -jsolaris,-sdebug,-sdefault,-hcritbit,ports *** v2 debug|now = 5929794.430894 (mono), 1773717717.996709 (real) *** v2 debug|Backtrace: *** v2 debug| 8149fb3: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'vbt_execinfo+0x39 [0x8149fb3] *** v2 debug| 814a1c4: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VBT_format+0x2d [0x814a1c4] *** v2 debug| 80aecdd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_backtrace+0x34 [0x80aecdd] *** v2 debug| 80af020: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_ic+0x27c [0x80af020] *** v2 debug| 81495b9: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VAS_Fail+0x3a [0x81495b9] *** v2 debug| 80a882d *** v2 debug|: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cli_quit+0x88 [0x80a882d] *** v2 debug| fedfad15: /lib/libc.so.1'__sighndlr+0x15 [0xfedfad15] *** v2 debug| fedee8d1: /lib/libc.so.1'call_user_handler+0x1e7 [0xfedee8d1] *** v2 debug| fedeeaf9: /lib/libc.so.1'sigacthandler+0xfd [0xfedeeaf9] *** v2 debug| ffffffff: [0xffffffff] *** v2 debug| 815d5f8: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VTIM_sleep+0x4d [0x815d5f8] *** v2 debug| 8112c45: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'smd_open+0x5a [0x8112c45] *** v2 debug| 810eb32: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'STV_open+0x1f6 [0x810eb32] *** v2 debug| 80a8fdb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'child_main+0x376 [0x80a8fdb] *** v2 debug| 80f805e: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_launch_child+0x3f8 [0x80f805e] *** v2 debug| 80f8e52: /tmp/vtest.gcc13_m32_I *** v2 debug|Pv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mch_cli_server_start+0x28 [0x80f8e52] *** v2 debug| 814b159: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_dispatch+0x2ec [0x814b159] *** v2 debug| 814b3cb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_exec+0x260 [0x814b3cb] *** v2 debug| 814b8a8: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'cls_feed+0x392 [0x814b8a8] *** v2 debug| 814c846: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VCLS_Poll+0x2a4 [0x814c846] *** v2 debug|argv = { *** v2 debug| [0] = \"vinyld\", *** v2 debug| [1] = \"-d\", *** v2 debug| [2] = \"-n\", *** v2 debug| [3] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v2\", *** v2 debug| [4] = \"-i\", *** v2 debug| [5] = \"v2\", *** v2 debug| [6] = \"-l\", *** v2 debug| [7] = \"2m\", *** v2 debug| [8] = \"-p\", *** v2 debug| [9] = \"auto_restart=off\", *** v2 debug| [10] = \"-p\", *** v2 debug| [11] = \"syslog_cli_traffic=off\", *** v2 debug| [12] = \"-p\", *** v2 debug| [13] = \"thread_pool_min=10\", *** v2 debug| [14] = \"-p\", *** v2 debug| [15] = \"deb *** v2 debug|ug=+vtc_mode\", *** v2 debug| [16] = \"-p\", *** v2 debug| [17] = \"vsl_mask=+Debug,+H2RxHdr,+H2RxBody\", *** v2 debug| [18] = \"-p\", *** v2 debug| [19] = \"h2_initial_window_size=1m\", *** v2 debug| [20] = \"-p\", *** v2 debug| [21] = \"h2_rx_window_low_water=64k\", *** v2 debug| [22] = \"-a\", *** v2 debug| [23] = \"127.0.0.1:0\", *** v2 debug| [24] = \"-M\", *** v2 debug| [25] = \"127.0.0.1 57995\", *** v2 debug| [26] = \"-P\", *** v2 debug| [27] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/v2/vinyld.pid\", *** v2 debug| [28] = \"-p\", *** v2 debug| [29] = \"vmod_path=/tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/vmod/.libs:\", *** v2 debug| [30] = \"-sdebug=debug,dopen=5s\", *** v2 debug| [31] = \"-pstartup_timeout=2s\", *** v2 debug| [32] = \"-pcli_timeout=3s\", *** v2 debug| [33] = \"-p\", *** v2 debug| [34] = \"feature=+no_coredump\", *** v2 debug|} *** v2 debug|pthread.self = 1 *** v2 debug|pthread.name = (cache-main) *** v2 debug|thr.req = NULL *** v2 debug|thr.busyobj = NULL *** v2 debug|thr.worker = NULL *** v2 debug|vmods = { *** v2 debug|}, *** v2 debug|pools = { *** v2 debug| pool = 827efb8 { *** v2 debug| nidle = 9, *** v2 debug| nthr = 10, *** v2 debug| lqueue = 0 *** v2 debug| }, *** v2 debug| pool = 82bf920 { *** v2 debug| nidle = 9, *** v2 debug| nthr = 10, *** v2 debug| lqueue = 0 *** v2 debug| }, *** v2 debug|}, *** v2 debug| *** v2 debug| *** v2 debug|Debug: Child cleanup complete *** v2 CLI RX 400 **** v2 CLI RX|Child failed on launch within cli_timeout=3.00s (tip: set startup_timeout) ** v2 CLI 400 ** top === vinyl v2 -cliok "panic.clear" **** v2 CLI TX|panic.clear *** v2 CLI RX 200 ** v2 CLI 200 ** top === vinyl v2 -wait ** v2 Wait **** v2 CLI TX|backend.list *** v2 CLI RX 101 **** v2 CLI RX|Unknown request in manager process (child not running). **** v2 CLI RX|Type 'help' for more info. ** v2 Stop **** v2 CLI TX|stop *** v2 CLI RX 300 **** v2 CLI RX|Child in state stopped *** v2 wait-stopped **** v2 CLI TX|status *** v2 CLI RX 200 **** v2 CLI RX|Child in state stopped **** v2 CLI TX|panic.show *** v2 CLI RX 300 **** v2 CLI RX|Child has not panicked or panic has been cleared *** v2 debug|Info: manager stopping child *** v2 debug| *** v2 debug|Info: *** v2 debug| *** v2 debug|manager dies *** v2 debug| **** dT 15.961 **** v2 STDOUT EOF **** dT 16.045 ** v2 WAIT4 pid=432237 status=0x4000 (user 0.623000 sys 0.128000) ** top === process p2 { vinyld \ **** dT 16.057 **** p2 CMD: vinyld \ -sdebug=debug,dopen=5s \ -pstartup_timeout=2s -pcli_timeout=3s \ -n /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p2 -a :0 -b none **** dT 16.058 *** p2 PID: 432562 **** dT 16.059 **** p2 macro def p2_pid=432562 **** p2 macro def p2_dir=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p2 **** p2 macro def p2_out=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p2/term **** p2 macro def p2_err=/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p2/stderr **** dT 16.806 **** p2 stderr|Warnings: **** p2 stderr|Message from VCC-compiler: **** p2 stderr|Security: proc_setid missing, uid/gid unchanged **** p2 stderr|Message from C-compiler: **** p2 stderr|Security: proc_setid missing, uid/gid unchanged **** p2 stderr|Message from dlopen: **** p2 stderr|Security: proc_setid missing, uid/gid unchanged **** p2 stderr| **** dT 16.817 **** p2 stderr|Warning: mlock() of VSM failed: Not owner (1) **** dT 16.914 **** p2 stderr|Error: Child failed on launch **** p2 stderr|Error: Child (432785) said Child starts **** p2 stderr|Error: Child (432785) said -sdebug init delay 0.000000s **** p2 stderr|Error: Child (432785) said -sdebug open delay in init 5.000000s **** p2 stderr|Error: Child (432785) said Security: proc_setid missing, uid/gid unchanged **** dT 17.014 **** p2 stderr|Error: Child (432785) died signal=6 **** p2 stderr|Error: Child (432785) Panic at: Tue, 17 Mar 2026 03:21:59 GMT **** p2 stderr|Wrong turn at ../../../../bin/vinyld/cache/cache_wrk.c:121: **** p2 stderr|pthread_create(thr, ((void *)0), wrk_bgthread, bt) failed **** p2 stderr|version = vinyl-cache-trunk revision 17ea9216e8091e8bd4b65a2e0b946c92de2125f4, vrt api = 23.0 **** p2 stderr|ident = -jsolaris,-sdebug,-sdefault,-hcritbit,ports **** p2 stderr|now = 5929795.482479 (mono), 1773717719.048272 (real) **** p2 stderr|Backtrace: **** p2 stderr| 8149fb3: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'vbt_execinfo+0x39 [0x8149fb3] **** p2 stderr| 814a1c4: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'VBT_format+0x2d [0x814a1c4] **** p2 stderr| 80aecdd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_backtrace+0x34 [0x80aecdd] **** p2 stderr| 80af020: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'pan_ic+0x27c [0x80af020] **** p2 stderr| 81495b9: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld **** dT 17.015 **** p2 stderr|'VAS_Fail+0x3a [0x81495b9] **** p2 stderr| 80d93dd: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'WRK_BgThread+0xa6 [0x80d93dd] **** p2 stderr| 8094ece: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'EXP_Init+0xd9 [0x8094ece] **** p2 stderr| 80a8fbb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'child_main+0x356 [0x80a8fbb] **** p2 stderr| 80f805e: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'mgt_launch_child+0x3f8 [0x80f805e] **** p2 stderr| 80f8d43: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'MCH_Start_Child+0x10 [0x80f8d43] **** p2 stderr| 80fff45: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'main+0x15c9 [0x80fff45] **** p2 stderr| 80728bb: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-cache-trunk/_build/sub/bin/vinyld/vinyld'_start_crt+0x9a [0x80728bb] **** p2 stderr| 807278a: /tmp/vtest.gcc13_m32_IPv4_uffix/varnish-cache/vinyl-c **** p2 stderr|ache-trunk/_build/sub/bin/vinyld/vinyld'_start+0x1a [0x807278a] **** p2 stderr|errno = 11 (Resource temporarily unavailable) **** p2 stderr|argv = { **** p2 stderr| [0] = \"vinyld\", **** p2 stderr| [1] = \"-sdebug=debug,dopen=5s\", **** p2 stderr| [2] = \"-pstartup_timeout=2s\", **** p2 stderr| [3] = \"-pcli_timeout=3s\", **** p2 stderr| [4] = \"-n\", **** p2 stderr| [5] = \"/tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p2\", **** p2 stderr| [6] = \"-a\", **** p2 stderr| [7] = \":0\", **** p2 stderr| [8] = \"-b\", **** p2 stderr| [9] = \"none\", **** p2 stderr|} **** p2 stderr|pthread.self = 1 **** p2 stderr|pthread.name = (cache-main) **** p2 stderr|thr.req = NULL **** p2 stderr|thr.busyobj = NULL **** p2 stderr|thr.worker = NULL **** p2 stderr|vmods = { **** p2 stderr|}, **** p2 stderr|pools = { **** p2 stderr| pool = 8280588 { **** p2 stderr| nidle = 98, **** p2 stderr| nthr = 100, **** p2 stderr| lqueue = 0 **** p2 stderr| }, **** p2 stderr|}, **** p2 stderr| **** p2 stderr| **** dT 17.057 **** p2 stderr read 0 **** p2 stdout read 0 **** dT 17.059 ** p2 WAIT4 pid=432562 status=0x0200 (user 0.003000 sys 0.007000) **** p2 macro undef p2_pid **** p2 stdout 0 bytes, stderr 3222 bytes ** top === shell {grep -q "launch within cli_timeout=3.00s (tip: set st... **** top shell_cmd|set -e ;exec 2>&1 ; grep -q "launch within cli_timeout=3.00s (tip: set startup_" /tmp/vtest.gcc13_m32_IPv4_uffix/_vtest_tmp/vtc.428840.769974d8/p2/stderr **** dT 17.069 **** top shell_status = 0x0001 ---- top shell_exit not as expected: got 0x0001 wanted 0x0000 * top RESETTING after ../../../../bin/vinyltest/tests/r03940.vtc * top TEST ../../../../bin/vinyltest/tests/r03940.vtc FAILED # top TEST ../../../../bin/vinyltest/tests/r03940.vtc FAILED (17.071) exit=2 FAIL tests/r03940.vtc (exit status: 2)